CONTENTS | INDEX | PREV | NEXT
FUNCTION
Code Profiler
SYNOPSIS
DPROF proffile [-call]
DESCRIPTION
This utility allows you to discover where time is used in your
program. Careful analysis of the output can help you focus on areas
of your code that would be most valuable to optimize.
DPROF generates profiling output from the binary data file generated
by an executable which was compiled with profiling enabled.
In order to use DPROF you must compile your program with the -prof
option. There are three levels of profiling:
Dcc Option : Effect
===========+=========================================================
-prof1 : Profile only your code
-----------+---------------------------------------------------------
-prof2 : Profile your code and the standard C library
-----------+---------------------------------------------------------
-prof3 : Profile your code, the C library, and the Amiga library
: tags
-----------+---------------------------------------------------------
To use -prof2 you must have installed DLIB:CSP.LIB (small data
profiled c.lib) or DLIB:CSRP.LIB (small data profiled c.lib for
registered arguments).
To use -prof3 you must have installed DLIB:AMIGASP20.LIB (small data
profiled amiga.lib) or DLIB:AMIGASRP20.LIB (small data profiled
amiga.lib for registered arguments).
USAGE
## WARNING: The profiling code is accurate to 20 microseconds under
## 2.0, 1/60 second under 1.3. The profiling code itself will slow
## down a program by quite a bit but, in general, the system makes
## every attempt to filter out its profiling overhead in the
## statistics file (so the grand total time will be less then the
## actual amount of time the program took to run).
Note, however, that the results will be skewed somewhat anyway, not
only due to the overhead of the profiling code, but also due to task
switches and other system overhead. To get accurate results you
should only run the executable that is to generate a .dprof file on
an unloaded system (i.e. don't do anything else while the executable
is running). Many calls to very short, quick routines will suffer
the most and numbers should be taken more in a qualitative fashion
than a quantitative fashion.
Keep in mind that it is not necessary to profile everything,
particularly for large projects. You may want most of the system to
run at full speed while only profiling a small part of it at a time.
EXAMPLE
Given a program called example.c (you can clip this from the online
help and compile it):
void fubar1(void);
void fubar2(void);
void loop(long);
main(ac, av)
char *av[];
{
short i;
for (i = 0; i < 100; ++i)
{
fubar1();
fubar2();
}
loop(10);
fubar1();
fubar2();
}
void fubar1()
{
short j;
for (j = 0; j < 10000; ++j);
fubar2();
}
void fubar2()
{
short j;
for (j = 0; j < 100; ++j);
}
void loop(n)
{
if (n)
loop(n - 1);
}
Compile and the run the program, then dump the profile. the DPROF
program automatically appends '.dprof' onto the filename you
specify.
1> dcc test.c -o test -prof1
1> test
1> dprof test
@@($)DPROF V2.06.01 Sep 30 1991 test.dprof
GrandTotal: 539.53 mS
**** BY ROUTINE ****
_main calls=1 total= 539.53 mS (100.00%) local= 10.37 mS (
1.92%)
_fubar1 calls=101 total= 517.45 mS ( 95.90%) local= 507.75 mS (
94.10%)
_fubar2 calls=202 total= 20.44 mS ( 3.79%) local= 20.44 mS (
3.79%)
_loop calls=11 total= 0.96 mS ( 0.17%) local= 0.96 mS (
0.17%)
The total numbers are time spent in the function. The local numbers
are the same, except time spent calling other profiled subfunctions
have been subtracted out.
**** BY PARENT ****
_fubar2 calls=202 total= 20.44 mS
From _fubar1 calls=101 total= 9.69 mS ( 47.43%)
From _main calls=101 total= 10.75 mS ( 52.56%)
This section shows who called the function, how many times, and how
long that took.
**** COMBINED CALL TREE ****
_main calls=1 tot= 539.53 (100.00) loc= 10.37 ( 1.92)
_fubar1 calls=101 tot= 517.45 ( 95.90) loc= 507.75 ( 94.10)
_fubar2 calls=101 tot= 10.75 ( 1.99) loc= 10.75 ( 1.99)
_loop calls=1 tot= 0.96 ( 0.17) loc= 0.08 ( 0.01)
The top line contains the same information from table 1. Here main()
calls fubar1() 101 times, fubar1() takes 517 mS total time over these
calls. Also, main() calls fubar2() directly 101 times and fubar2()
takes 10 mS over these calls. Note that fubar2()'s time is not the
same as in table 1 because only those calls made from main() are
counted here. Percentages are relative to main(). The profiled data
includes the entire call tree but for simplicity, recursive calls are
simply shown with <SELF>.
-call You can request DPROF to print out the entire call tree. This is
done by adding the -call option to dprof. Note, however, that
this option may result in a huge amount of data printed out. On
the other hand, sometimes the data is quite useful especially
when tracing subroutine stacking and other things.